Repository navigation
fix(core): Correct sleep clock drift on telemetry timestamps - #23054
Conversation
size-limit report 📦
|
|
The two-origin divergence Bugbot flagged is real: Fixed in #23067, stacked on top of this PR, which exposes the corrected origin and switches over the consumers where the divergence persists (INP, replay, and profiling's Keeping it out of this PR so each change stays independently reviewable — this one is limited to how |
|
Confirmed on a real iPhone running React Native 0.86 with One structured log embedded its emission wall time in the message body:
The full structured-log stream was present under the older window with the same displacement, while error events remained wall-clock-correct. This matches the React Native Apple clock change in react-native#55977 and the symptom reported in getsentry/sentry-react-native#6510. We applied the same per-call re-anchoring shape downstream as a version-pinned patch. Package-level regression tests against the real One potentially useful addition to this PR's test suite: the current sleep test starts with an aligned first call and then accumulates drift. Our device also exercised the other entry condition, where |
|
This pull request has gone three weeks without activity. In another week, I will close it. But! If you comment or otherwise update it, I will reset the clock, and if you apply the label |
|
Getting the same issue, has this been closed permanently? |
|
@plgrazon no, this is still WIP but the change is non-trivial. I'm currently completely booked on the new JS major but I hope to get some time to pick this up next week again. |
|
@Lms24 no worries. thank you! |
456dd81 to
ded4f36
Compare
4ced6e1 to
3b14c70
Compare
Drift from timer precision or NTP slewing stays well below 1s, so a lower threshold catches more real clock jumps without false resets. Also simplify the comments in the time utils. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…gment If performance.timeOrigin is already wrong on the first timestamp call, we replace it. Pushing a second segment that also starts at 0 lets the segment cap drop the corrected origin later and keep the wrong one, so late-converted page load times would be off by the initial skew. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The initial load span used the page load time origin. Use the origin that was valid when the measure started instead, like all other performance entries, so a time origin correction in between does not shift it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
A page needs many sleeps or clock jumps to reach the cap. The list is small, so a higher cap costs little and keeps more late entries correct. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…ersion Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…oSeconds Add an optional entryStartTimeInMs parameter to performanceTimeToSeconds, so all timings of one entry can use the time origin from the entry's start. Use it instead of looking up the origin and converting by hand. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…manceTimeOrigin Running the drift check on every call is expensive in loops over many performance entries (e.g. browser profiling `convertToContinuousProfile`). Only check once per task and reset the flag in a microtask. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…meToSeconds The request span now uses performanceTimeToSeconds, but user timing spans still added seconds values. The two ways of computing can round differently in the last digit, so a measure that starts before the request could get a start time slightly before the request span. Use the same conversion in both places so they get the same timestamp. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
…s time origin The request start was converted with the navigation entry's time origin, while the measure used its own. After a backwards correction, a later measure could be clamped to the request start and then dropped. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
It is only meant for other Sentry packages, not for users. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
8db5ba3 to
148ff6f
Compare
There was a problem hiding this comment.
Cursor Bugbot has reviewed your changes and found 1 potential issue.
❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.
Reviewed by Cursor Bugbot for commit 148ff6f. Configure here.
…24903) After Spans #23054, spans that run while the time origin is corrected (e.g. after the device slept) get the drift added to their duration. However, If the wall clock jumps backwards, the duration can even be negative. Also, adding sleep time to spans is arguably unexpected and unprecedented in comparison to OpenTelemetry. This PR changes s `span.end()` without a explicit timestamp to compute the end as start time + `performance.now()` time since the start, [like OpenTelemetry does](https://github.com/open-telemetry/opentelemetry-js/blob/672b1d216e8b2299d16d7e2dfd184da4bf448cb4/packages/sdk-trace/src/Span.ts#L319-L356). Start times still use `timestampInSeconds()`, so real-time started spans and spans from performance entries stay on the same timeline. Tradeoff: when a correction happens while a span runs, its end is now based on the old time origin. So children or errors recorded after the correction can appear after the span ended. Spans with an explicit start time keep using `timestampInSeconds()` for the end. --------- Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Effect spans used Effect's own clock (a fixed origin plus a monotonic clock) for their start, end and event times. #23054 makes Sentry correct its clock for drift (e.g. after the device slept), so Effect spans could end up shifted by the drift relative to the Sentry spans around them. With this PR, an Effect span now starts on Sentry's clock, and its end and event times are converted by their offset from the span's start. This is the same per-span offset that OpenTelemetry's SDK uses. We also do this for our spans now, see #24903 for details. The PR keeps Effect's durations and any end time passed explicitly via `span.end(time, exit)`. With `withTracerTiming(false)`, Effect passes `0`, and we now use Sentry's clock instead of setting 1970 timestamps. Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
The Replay integration adding web vital breadcrumbs used the metric value as the timestamp for CLS and INP web vitals. This is incorrect because that value is a score for CLS and a duration for INP, so both events always landed just after page load. This was a pre-existing bug, but it showed up during work on #23054. With this PR, CLS goes at the last layout shift and INP at the interaction, like we already do with spans in tracing. Both also get the time origin from when that happened, so they stay correct after a clock drift correction. A CLS of 0 has no layout shift, so it stays at the start of its navigation --------- Co-authored-by: Claude <noreply@anthropic.com>
Follow-up to #23054, from [this review comment](#23054 (comment)). Besides `visibilitychange`, we now also check for clock drift on `freeze`/`resume` (TIL) and `pagehide`/`pageshow`. This way the time origin is corrected right at the emissions, not at the next regular timestamp call. `freeze` and `resume` only fire in Chromium. Other browsers never fire them, so the listeners do nothing there. --------- Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

This PR fixes* clock drift that occurs when devices go to sleep. After devices sleep for a few seconds, the browser's monotonic clock (accessed via
performance.now()) stops counting. Once the sleep stops, the monotonic clock resumes right where it left off before the sleep, causing significant discrepancies between the actual time (wall clock) and the browser's monotonic clock time. Or in other words, there are two ways to get an absolute timestamp:peformance.timeOrigin + performance.now()- has high, sub-millisecond precision and a guarantee that there are no time jumps or adjustments. But suffers from the sleep problem described aboveDate.now()- lower millisecond precision, is known to be corrected (NTP or via users) and can even cause back jumps. But no sleep problem.With this fix, we make the following adjustments, to kinda get the best of both worlds:
timestampInSecondsCallchecks the monotonic against the wall clock. If a threshold of difference is enocuntered, it corrects thetimeOriginso that we can keep using the precise monotonic clock, but anchor its relative time to a corrected time origin.browserPerformanceTimeOrigina time origin corrected helper function, where you pass in a relative time that comes from monotonic clock relative timestamps and it returns the time origin that was most accurate at that relative time point.PerformanceEntryobjects carry relative times which are completely sleep-drift uncorrected. We usebrowserPerformanceTimeOriginto return a corrected time stamp so that we can create an absolute timestamp and bring the performance entries to their respective actual time.FAQ
If you think this sounds complicated, I agree. So let me answer the most obvious questions, because I asked myself these a lot, too:
Why not just always use
Date.now()and avoid the complicated click drift detection and correction logic?The main issue with this is that we still need to rely on relative monotonic clock timestamps for performance entries. We cannot correct them just with
Date.now()alone but we still need to anchor them. So either we rely on the originalwindow.timeOriginand therefore have all performance entry telemetry happen much "earlier" than its surrounding telemetry relying onDate.now(), or we keep the time origin correction logic. But even in the second case (where we already pay the tax for drift detection and correction), telemetry would still have two different anchors:Date.now()for regular telemetry and the corrected time origin + monotonic time for performance entry telemetry.Another reason is that the monotonic clock gives us sun-millisecond precision while the wall clock stops at a millisecond resolution.
Why the reduction from a drift detection threshold of 5 minutes to just one second?
Because we keep everything centered around detection and origin offset correction, these timestamps need to be as accurate as possible. On phones, short frequent sleeps are very likely to happen. A lot of sleeps can accumulate until that 5 minutes threshold is reached. So it's really important we make these timestamps as accurate as possible.
Fwiw, I reproduced this locally and the drift is already noticeable after just a few seconds of sleep. The 5 minutes threshold was arguably far too big beforehand.
Is there precedence for all of this stuff?
Somewhat, but I'd argue we're doing a bit more: OTel uses a mixture of
Date.now()andperformance.now:Date.now()and at start time, they record aperformance.now()timestamp. On span end, they also takeperformance.now(), compute the diff and convert that to an end timestamp based on the start timestamp + diff. This is neat because it guarantees monotony in span durations. I stole this in fix(core): Compute span end time fromperformance.now()duration #24903In other places, OTel relies purely on Date.now(), and for performance entries, they simply take uncorrected timestamps. So our fix is more complete.
* So... we're good now?
Well, not perfectly and we never will. With this choice we make another commitment (which we already did previously in less obvious cases) to
Date.now(). This value can drift as well, just not for sleeps:I think we'll have to live with both and I'm not particularly worried about them. My main objective is getting rid of the sleep drift.
Fixes #2590
Fixes #22375
Supersedes #22488, #22585, #23067, #23068